From: Aleksey Kladov <aleksey.kladov@gmail.com>
Date: Sun, 8 Apr 2018 08:37:05 +0000 (+0300)
Subject: Don't print profiling information twice
X-Git-Tag: archive/raspbian/0.35.0-2+rpi1~3^2^2^2^2^2^2^2~22^2~1^2~88^2
X-Git-Url: https://dgit.raspbian.org/%22http://www.example.com/cgi/success//%22http:/www.example.com/cgi/success/?a=commitdiff_plain;h=154948837afbbfc312764b24982ba7dbac0d4ebd;p=cargo.git

Don't print profiling information twice

It's important to `.clear` the messages so that we don't print them
again for the next "profiling session". It might be argued that really
we should have a single "profiling session" for Cargo, but we don't at
the moment.

And, while we are at it, let's lock stdout as well, so that we won't
get confused when Cargo becomes multi-threaded and prints profiling info
from several threads simultaneously.
---

diff --git a/src/cargo/util/profile.rs b/src/cargo/util/profile.rs
index 7d32adc3f..ce49eee26 100644
--- a/src/cargo/util/profile.rs
+++ b/src/cargo/util/profile.rs
@@ -4,6 +4,7 @@ use std::mem;
 use std::time;
 use std::iter::repeat;
 use std::cell::RefCell;
+use std::io::{stdout, StdoutLock, Write};
 
 thread_local!(static PROFILE_STACK: RefCell<Vec<time::Instant>> = RefCell::new(Vec::new()));
 thread_local!(static MESSAGES: RefCell<Vec<Message>> = RefCell::new(Vec::new()));
@@ -39,14 +40,24 @@ impl Drop for Profiler {
             None => return,
         };
 
-        let start = PROFILE_STACK.with(|stack| stack.borrow_mut().pop().unwrap());
+        let (start, stack_len) = PROFILE_STACK.with(|stack| {
+            let mut stack = stack.borrow_mut();
+            let start = stack.pop().unwrap();
+            (start, stack.len())
+        });
         let duration = start.elapsed();
         let duration_ms =
             duration.as_secs() * 1000 + u64::from(duration.subsec_nanos() / 1_000_000);
 
-        let stack_len = PROFILE_STACK.with(|stack| stack.borrow().len());
+        let msg = (
+            stack_len,
+            duration_ms,
+            mem::replace(&mut self.desc, String::new()),
+        );
+        MESSAGES.with(|msgs| msgs.borrow_mut().push(msg));
+
         if stack_len == 0 {
-            fn print(lvl: usize, msgs: &[Message], enabled: usize) {
+            fn print(lvl: usize, msgs: &[Message], enabled: usize, stdout: &mut StdoutLock) {
                 if lvl > enabled {
                     return;
                 }
@@ -55,26 +66,23 @@ impl Drop for Profiler {
                     if l != lvl {
                         continue;
                     }
-                    println!(
+                    writeln!(
+                        stdout,
                         "{} {:6}ms - {}",
                         repeat("    ").take(lvl + 1).collect::<String>(),
                         time,
                         msg
-                    );
+                    ).expect("printing profiling info to stdout");
 
-                    print(lvl + 1, &msgs[last..i], enabled);
+                    print(lvl + 1, &msgs[last..i], enabled, stdout);
                     last = i;
                 }
             }
-            MESSAGES.with(|msgs_rc| {
-                let mut msgs = msgs_rc.borrow_mut();
-                msgs.push((0, duration_ms, mem::replace(&mut self.desc, String::new())));
-                print(0, &msgs, enabled);
-            });
-        } else {
+            let stdout = stdout();
             MESSAGES.with(|msgs| {
-                let msg = mem::replace(&mut self.desc, String::new());
-                msgs.borrow_mut().push((stack_len, duration_ms, msg));
+                let mut msgs = msgs.borrow_mut();
+                print(0, &msgs, enabled, &mut stdout.lock());
+                msgs.clear();
             });
         }
     }